// Copyright (c) 2013 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.

#include "net/quic/quic_connection_logger.h"

#include <algorithm>
#include <limits>
#include <memory>
#include <utility>
#include <vector>

#include "base/bind.h"
#include "base/callback.h"
#include "base/metrics/histogram_base.h"
#include "base/metrics/histogram_macros.h"
#include "base/metrics/sparse_histogram.h"
#include "base/profiler/scoped_tracker.h"
#include "base/strings/string_number_conversions.h"
#include "base/values.h"
#include "net/base/ip_address.h"
#include "net/cert/x509_certificate.h"
#include "net/quic/crypto/crypto_handshake_message.h"
#include "net/quic/crypto/crypto_protocol.h"
#include "net/quic/quic_address_mismatch.h"
#include "net/quic/quic_protocol.h"
#include "net/quic/quic_socket_address_coder.h"
#include "net/quic/quic_time.h"

using base::StringPiece;
using std::string;

namespace net {

namespace {

    // We have ranges-of-buckets in the cumulative histogram (covering 21 packet
    // sequences) of length 2, 3, 4, ... 22.
    // Hence the largest sample is bounded by the sum of those numbers.
    const int kBoundingSampleInCumulativeHistogram = ((2 + 22) * 21) / 2;

    std::unique_ptr<base::Value> NetLogQuicPacketCallback(
        const IPEndPoint* self_address,
        const IPEndPoint* peer_address,
        size_t packet_size,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetString("self_address", self_address->ToString());
        dict->SetString("peer_address", peer_address->ToString());
        dict->SetInteger("size", packet_size);
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicPacketSentCallback(
        const SerializedPacket& serialized_packet,
        TransmissionType transmission_type,
        QuicTime sent_time,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetInteger("transmission_type", transmission_type);
        dict->SetString("packet_number",
            base::Uint64ToString(serialized_packet.packet_number));
        dict->SetInteger("size", serialized_packet.encrypted_length);
        dict->SetString("sent_time_us",
            base::Int64ToString(sent_time.ToDebuggingValue()));
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicPacketRetransmittedCallback(
        QuicPacketNumber old_packet_number,
        QuicPacketNumber new_packet_number,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetString("old_packet_number", base::Uint64ToString(old_packet_number));
        dict->SetString("new_packet_number", base::Uint64ToString(new_packet_number));
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicDuplicatePacketCallback(
        QuicPacketNumber packet_number,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetString("packet_number", base::Uint64ToString(packet_number));
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicPacketHeaderCallback(
        const QuicPacketHeader* header,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetString("connection_id",
            base::Uint64ToString(header->public_header.connection_id));
        dict->SetInteger("reset_flag", header->public_header.reset_flag);
        dict->SetInteger("version_flag", header->public_header.version_flag);
        dict->SetString("packet_number", base::Uint64ToString(header->packet_number));
        dict->SetInteger("entropy_flag", header->entropy_flag);
        dict->SetInteger("fec_flag", header->fec_flag);
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicStreamFrameCallback(
        const QuicStreamFrame* frame,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetInteger("stream_id", frame->stream_id);
        dict->SetBoolean("fin", frame->fin);
        dict->SetString("offset", base::Uint64ToString(frame->offset));
        dict->SetInteger("length", frame->data_length);
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicAckFrameCallback(
        const QuicAckFrame* frame,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetString("largest_observed",
            base::Uint64ToString(frame->largest_observed));
        dict->SetString("delta_time_largest_observed_us",
            base::Int64ToString(frame->ack_delay_time.ToMicroseconds()));
        if (frame->missing) {
            // Entropy and Truncated are not present in v34 and above.
            dict->SetInteger("entropy_hash", frame->entropy_hash);
            dict->SetBoolean("truncated", frame->is_truncated);
        }

        base::ListValue* missing = new base::ListValue();
        dict->Set("missing_packets", missing);
        if (frame->missing) {
            for (QuicPacketNumber packet : frame->packets)
                missing->AppendString(base::Uint64ToString(packet));
        } else if (!frame->packets.Empty()) {
            // V34 and above express acked packets, but only print
            // missing packets, because it's typically a shorter list.
            for (QuicPacketNumber packet = frame->packets.Min();
                 packet < frame->largest_observed; ++packet) {
                if (!frame->packets.Contains(packet)) {
                    missing->AppendString(base::Uint64ToString(packet));
                }
            }
        }

        base::ListValue* received = new base::ListValue();
        dict->Set("received_packet_times", received);
        const PacketTimeVector& received_times = frame->received_packet_times;
        for (PacketTimeVector::const_iterator it = received_times.begin();
             it != received_times.end(); ++it) {
            std::unique_ptr<base::DictionaryValue> info(new base::DictionaryValue());
            info->SetInteger("packet_number", static_cast<int>(it->first));
            info->SetString("received",
                base::Int64ToString(it->second.ToDebuggingValue()));
            received->Append(std::move(info));
        }

        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicRstStreamFrameCallback(
        const QuicRstStreamFrame* frame,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetInteger("stream_id", frame->stream_id);
        dict->SetInteger("quic_rst_stream_error", frame->error_code);
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicConnectionCloseFrameCallback(
        const QuicConnectionCloseFrame* frame,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetInteger("quic_error", frame->error_code);
        dict->SetString("details", frame->error_details);
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicWindowUpdateFrameCallback(
        const QuicWindowUpdateFrame* frame,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetInteger("stream_id", frame->stream_id);
        dict->SetString("byte_offset", base::Uint64ToString(frame->byte_offset));
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicBlockedFrameCallback(
        const QuicBlockedFrame* frame,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetInteger("stream_id", frame->stream_id);
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicGoAwayFrameCallback(
        const QuicGoAwayFrame* frame,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetInteger("quic_error", frame->error_code);
        dict->SetInteger("last_good_stream_id", frame->last_good_stream_id);
        dict->SetString("reason_phrase", frame->reason_phrase);
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicStopWaitingFrameCallback(
        const QuicStopWaitingFrame* frame,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        base::DictionaryValue* sent_info = new base::DictionaryValue();
        dict->Set("sent_info", sent_info);
        sent_info->SetString("least_unacked",
            base::Uint64ToString(frame->least_unacked));
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicVersionNegotiationPacketCallback(
        const QuicVersionNegotiationPacket* packet,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        base::ListValue* versions = new base::ListValue();
        dict->Set("versions", versions);
        for (QuicVersionVector::const_iterator it = packet->versions.begin();
             it != packet->versions.end(); ++it) {
            versions->AppendString(QuicVersionToString(*it));
        }
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicCryptoHandshakeMessageCallback(
        const CryptoHandshakeMessage* message,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetString("quic_crypto_handshake_message", message->DebugString());
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicOnConnectionClosedCallback(
        QuicErrorCode error,
        ConnectionCloseSource source,
        NetLogCaptureMode /* capture_mode */)
    {
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        dict->SetInteger("quic_error", error);
        dict->SetBoolean("from_peer",
            source == ConnectionCloseSource::FROM_PEER ? true : false);
        return std::move(dict);
    }

    std::unique_ptr<base::Value> NetLogQuicCertificateVerifiedCallback(
        scoped_refptr<X509Certificate> cert,
        NetLogCaptureMode /* capture_mode */)
    {
        // Only the subjects are logged so that we can investigate connection pooling.
        // More fields could be logged in the future.
        std::vector<std::string> dns_names;
        cert->GetDNSNames(&dns_names);
        std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
        base::ListValue* subjects = new base::ListValue();
        for (std::vector<std::string>::const_iterator it = dns_names.begin();
             it != dns_names.end(); it++) {
            subjects->AppendString(*it);
        }
        dict->Set("subjects", subjects);
        return std::move(dict);
    }

    void UpdatePacketGapSentHistogram(size_t num_consecutive_missing_packets)
    {
        UMA_HISTOGRAM_COUNTS("Net.QuicSession.PacketGapSent",
            num_consecutive_missing_packets);
    }

    void UpdatePublicResetAddressMismatchHistogram(
        const IPEndPoint& server_hello_address,
        const IPEndPoint& public_reset_address)
    {
        int sample = GetAddressMismatch(server_hello_address, public_reset_address);
        // We are seemingly talking to an older server that does not support the
        // feature, so we can't report the results in the histogram.
        if (sample < 0) {
            return;
        }
        UMA_HISTOGRAM_ENUMERATION("Net.QuicSession.PublicResetAddressMismatch2",
            sample, QUIC_ADDRESS_MISMATCH_MAX);
    }

    // If |address| is an IPv4-mapped IPv6 address, returns ADDRESS_FAMILY_IPV4
    // instead of ADDRESS_FAMILY_IPV6. Othewise, behaves like GetAddressFamily().
    AddressFamily GetRealAddressFamily(const IPAddress& address)
    {
        return address.IsIPv4MappedIPv6() ? ADDRESS_FAMILY_IPV4
                                          : GetAddressFamily(address);
    }

} // namespace

QuicConnectionLogger::QuicConnectionLogger(
    QuicSpdySession* session,
    const char* const connection_description,
    std::unique_ptr<SocketPerformanceWatcher> socket_performance_watcher,
    const BoundNetLog& net_log)
    : net_log_(net_log)
    , session_(session)
    , last_received_packet_number_(0)
    , last_received_packet_size_(0)
    , previous_received_packet_size_(0)
    , last_packet_sent_time_(base::TimeTicks())
    , largest_received_packet_number_(0)
    , largest_received_missing_packet_number_(0)
    , num_out_of_order_received_packets_(0)
    , num_out_of_order_large_received_packets_(0)
    , num_packets_received_(0)
    , num_truncated_acks_sent_(0)
    , num_truncated_acks_received_(0)
    , num_frames_received_(0)
    , num_duplicate_frames_received_(0)
    , num_incorrect_connection_ids_(0)
    , num_undecryptable_packets_(0)
    , num_duplicate_packets_(0)
    , num_blocked_frames_received_(0)
    , num_blocked_frames_sent_(0)
    , connection_description_(connection_description)
    , socket_performance_watcher_(std::move(socket_performance_watcher))
{
}

QuicConnectionLogger::~QuicConnectionLogger()
{
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.OutOfOrderPacketsReceived",
        num_out_of_order_received_packets_);
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.OutOfOrderLargePacketsReceived",
        num_out_of_order_large_received_packets_);
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.TruncatedAcksSent",
        num_truncated_acks_sent_);
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.TruncatedAcksReceived",
        num_truncated_acks_received_);
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.IncorrectConnectionIDsReceived",
        num_incorrect_connection_ids_);
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.UndecryptablePacketsReceived",
        num_undecryptable_packets_);
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.DuplicatePacketsReceived",
        num_duplicate_packets_);
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.BlockedFrames.Received",
        num_blocked_frames_received_);
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.BlockedFrames.Sent",
        num_blocked_frames_sent_);
    UMA_HISTOGRAM_COUNTS("Net.QuicSession.HeadersStream.EarlyFramesReceived",
        session_->headers_stream()->num_early_frames_received());

    if (num_frames_received_ > 0) {
        int duplicate_stream_frame_per_thousand = num_duplicate_frames_received_ * 1000 / num_frames_received_;
        if (num_packets_received_ < 100) {
            UMA_HISTOGRAM_CUSTOM_COUNTS(
                "Net.QuicSession.StreamFrameDuplicatedShortConnection",
                duplicate_stream_frame_per_thousand, 1, 1000, 75);
        } else {
            UMA_HISTOGRAM_CUSTOM_COUNTS(
                "Net.QuicSession.StreamFrameDuplicatedLongConnection",
                duplicate_stream_frame_per_thousand, 1, 1000, 75);
        }
    }

    RecordLossHistograms();
}

void QuicConnectionLogger::OnFrameAddedToPacket(const QuicFrame& frame)
{
    switch (frame.type) {
    case PADDING_FRAME:
        break;
    case STREAM_FRAME:
        net_log_.AddEvent(
            NetLog::TYPE_QUIC_SESSION_STREAM_FRAME_SENT,
            base::Bind(&NetLogQuicStreamFrameCallback, frame.stream_frame));
        break;
    case ACK_FRAME: {
        net_log_.AddEvent(
            NetLog::TYPE_QUIC_SESSION_ACK_FRAME_SENT,
            base::Bind(&NetLogQuicAckFrameCallback, frame.ack_frame));
        // Missing packets histogram only relevant for v33 and lower
        // TODO(rch, rtenneti) sort out histograms for v34+
        if (session_->connection()->version() > QUIC_VERSION_33) {
            break;
        }
        const PacketNumberQueue& missing_packets = frame.ack_frame->packets;
        const uint8_t max_ranges = std::numeric_limits<uint8_t>::max();
        // Compute an upper bound on the number of NACK ranges. If the bound
        // is below the max, then it clearly isn't truncated.
        if (missing_packets.NumPacketsSlow() < max_ranges || (missing_packets.Max() - missing_packets.Min() - missing_packets.NumPacketsSlow() + 1) < max_ranges) {
            break;
        }
        size_t num_ranges = 0;
        QuicPacketNumber last_missing = 0;
        for (QuicPacketNumber packet : missing_packets) {
            if (packet != last_missing + 1 && ++num_ranges >= max_ranges) {
                ++num_truncated_acks_sent_;
                break;
            }
            last_missing = packet;
        }
        break;
    }
    case RST_STREAM_FRAME:
        UMA_HISTOGRAM_SPARSE_SLOWLY("Net.QuicSession.RstStreamErrorCodeClient",
            frame.rst_stream_frame->error_code);
        net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_RST_STREAM_FRAME_SENT,
            base::Bind(&NetLogQuicRstStreamFrameCallback,
                frame.rst_stream_frame));
        break;
    case CONNECTION_CLOSE_FRAME:
        net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_CONNECTION_CLOSE_FRAME_SENT,
            base::Bind(&NetLogQuicConnectionCloseFrameCallback,
                frame.connection_close_frame));
        break;
    case GOAWAY_FRAME:
        net_log_.AddEvent(
            NetLog::TYPE_QUIC_SESSION_GOAWAY_FRAME_SENT,
            base::Bind(&NetLogQuicGoAwayFrameCallback, frame.goaway_frame));
        break;
    case WINDOW_UPDATE_FRAME:
        net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_WINDOW_UPDATE_FRAME_SENT,
            base::Bind(&NetLogQuicWindowUpdateFrameCallback,
                frame.window_update_frame));
        break;
    case BLOCKED_FRAME:
        ++num_blocked_frames_sent_;
        net_log_.AddEvent(
            NetLog::TYPE_QUIC_SESSION_BLOCKED_FRAME_SENT,
            base::Bind(&NetLogQuicBlockedFrameCallback, frame.blocked_frame));
        break;
    case STOP_WAITING_FRAME:
        net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_STOP_WAITING_FRAME_SENT,
            base::Bind(&NetLogQuicStopWaitingFrameCallback,
                frame.stop_waiting_frame));
        break;
    case PING_FRAME:
        UMA_HISTOGRAM_BOOLEAN("Net.QuicSession.ConnectionFlowControlBlocked",
            session_->IsConnectionFlowControlBlocked());
        UMA_HISTOGRAM_BOOLEAN("Net.QuicSession.StreamFlowControlBlocked",
            session_->IsStreamFlowControlBlocked());
        // PingFrame has no contents to log, so just record that it was sent.
        net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_PING_FRAME_SENT);
        break;
    case MTU_DISCOVERY_FRAME:
        // MtuDiscoveryFrame is PingFrame on wire, it does not have any payload.
        net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_MTU_DISCOVERY_FRAME_SENT);
        break;
    default:
        DCHECK(false) << "Illegal frame type: " << frame.type;
    }
}

void QuicConnectionLogger::OnPacketSent(
    const SerializedPacket& serialized_packet,
    QuicPathId /* original_path_id */,
    QuicPacketNumber original_packet_number,
    TransmissionType transmission_type,
    QuicTime sent_time)
{
    if (original_packet_number == 0) {
        net_log_.AddEvent(
            NetLog::TYPE_QUIC_SESSION_PACKET_SENT,
            base::Bind(&NetLogQuicPacketSentCallback, serialized_packet,
                transmission_type, sent_time));
    } else {
        net_log_.AddEvent(
            NetLog::TYPE_QUIC_SESSION_PACKET_RETRANSMITTED,
            base::Bind(&NetLogQuicPacketRetransmittedCallback,
                original_packet_number, serialized_packet.packet_number));
    }
    // Record time duration from last packet sent to the new packet sent.
    if (last_packet_sent_time_.IsInitialized()) {
        UMA_HISTOGRAM_CUSTOM_TIMES(
            "Net.QuicTimeBetweenTwoPacketSent",
            base::TimeDelta::FromMilliseconds(
                sent_time.Subtract(last_packet_sent_time_).ToMilliseconds()),
            base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromMinutes(10),
            100);
    }
    last_packet_sent_time_ = sent_time;
}

void QuicConnectionLogger::OnPacketReceived(const IPEndPoint& self_address,
    const IPEndPoint& peer_address,
    const QuicEncryptedPacket& packet)
{
    if (local_address_from_self_.GetFamily() == ADDRESS_FAMILY_UNSPECIFIED) {
        local_address_from_self_ = self_address;
        UMA_HISTOGRAM_ENUMERATION("Net.QuicSession.ConnectionTypeFromSelf",
            GetRealAddressFamily(self_address.address()),
            ADDRESS_FAMILY_LAST);
    }

    previous_received_packet_size_ = last_received_packet_size_;
    last_received_packet_size_ = packet.length();
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_PACKET_RECEIVED,
        base::Bind(&NetLogQuicPacketCallback, &self_address,
            &peer_address, packet.length()));
}

void QuicConnectionLogger::OnUnauthenticatedHeader(
    const QuicPacketHeader& header)
{
    net_log_.AddEvent(
        NetLog::TYPE_QUIC_SESSION_UNAUTHENTICATED_PACKET_HEADER_RECEIVED,
        base::Bind(&NetLogQuicPacketHeaderCallback, &header));
}

void QuicConnectionLogger::OnIncorrectConnectionId(
    QuicConnectionId connection_id)
{
    ++num_incorrect_connection_ids_;
}

void QuicConnectionLogger::OnUndecryptablePacket()
{
    ++num_undecryptable_packets_;
}

void QuicConnectionLogger::OnDuplicatePacket(QuicPacketNumber packet_number)
{
    net_log_.AddEvent(
        NetLog::TYPE_QUIC_SESSION_DUPLICATE_PACKET_RECEIVED,
        base::Bind(&NetLogQuicDuplicatePacketCallback, packet_number));
    ++num_duplicate_packets_;
}

void QuicConnectionLogger::OnProtocolVersionMismatch(
    QuicVersion received_version)
{
    // TODO(rtenneti): Add logging.
}

void QuicConnectionLogger::OnPacketHeader(const QuicPacketHeader& header)
{
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_PACKET_AUTHENTICATED);
    ++num_packets_received_;
    if (largest_received_packet_number_ < header.packet_number) {
        QuicPacketNumber delta = header.packet_number - largest_received_packet_number_;
        if (delta > 1) {
            // There is a gap between the largest packet previously received and
            // the current packet.  This indicates either loss, or out-of-order
            // delivery.
            UMA_HISTOGRAM_COUNTS("Net.QuicSession.PacketGapReceived",
                static_cast<base::HistogramBase::Sample>(delta - 1));
        }
        largest_received_packet_number_ = header.packet_number;
    }
    if (header.packet_number < received_packets_.size()) {
        received_packets_[static_cast<size_t>(header.packet_number)] = true;
    }
    if (header.packet_number < last_received_packet_number_) {
        ++num_out_of_order_received_packets_;
        if (previous_received_packet_size_ < last_received_packet_size_)
            ++num_out_of_order_large_received_packets_;
        UMA_HISTOGRAM_COUNTS(
            "Net.QuicSession.OutOfOrderGapReceived",
            static_cast<base::HistogramBase::Sample>(last_received_packet_number_ - header.packet_number));
    }
    last_received_packet_number_ = header.packet_number;
}

void QuicConnectionLogger::OnStreamFrame(const QuicStreamFrame& frame)
{
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_STREAM_FRAME_RECEIVED,
        base::Bind(&NetLogQuicStreamFrameCallback, &frame));
}

void QuicConnectionLogger::OnAckFrame(const QuicAckFrame& frame)
{
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_ACK_FRAME_RECEIVED,
        base::Bind(&NetLogQuicAckFrameCallback, &frame));

    const size_t kApproximateLargestSoloAckBytes = 100;
    if (last_received_packet_number_ < received_acks_.size() && last_received_packet_size_ < kApproximateLargestSoloAckBytes) {
        received_acks_[static_cast<size_t>(last_received_packet_number_)] = true;
    }

    if (frame.is_truncated)
        ++num_truncated_acks_received_;

    if (frame.packets.Empty())
        return;

    // TODO(rch, rtenneti) sort out histograms for QUIC_VERSION_34 and above.
    if (session_->connection()->version() > QUIC_VERSION_33) {
        return;
    }
    const PacketNumberQueue& missing_packets = frame.packets;
    PacketNumberQueue::const_iterator it = missing_packets.lower_bound(largest_received_missing_packet_number_);
    if (it == missing_packets.end())
        return;

    if (*it == largest_received_missing_packet_number_) {
        ++it;
        if (it == missing_packets.end())
            return;
    }
    // Scan through the list and log consecutive ranges of missing packets.
    size_t num_consecutive_missing_packets = 0;
    QuicPacketNumber previous_missing_packet = *it - 1;
    while (it != missing_packets.end()) {
        if (previous_missing_packet == *it - 1) {
            ++num_consecutive_missing_packets;
        } else {
            DCHECK_NE(0u, num_consecutive_missing_packets);
            UpdatePacketGapSentHistogram(num_consecutive_missing_packets);
            // Make sure this packet it included in the count.
            num_consecutive_missing_packets = 1;
        }
        previous_missing_packet = *it;
        ++it;
    }
    if (num_consecutive_missing_packets != 0) {
        UpdatePacketGapSentHistogram(num_consecutive_missing_packets);
    }
    largest_received_missing_packet_number_ = missing_packets.Max();
}

void QuicConnectionLogger::OnStopWaitingFrame(
    const QuicStopWaitingFrame& frame)
{
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_STOP_WAITING_FRAME_RECEIVED,
        base::Bind(&NetLogQuicStopWaitingFrameCallback, &frame));
}

void QuicConnectionLogger::OnRstStreamFrame(const QuicRstStreamFrame& frame)
{
    UMA_HISTOGRAM_SPARSE_SLOWLY("Net.QuicSession.RstStreamErrorCodeServer",
        frame.error_code);
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_RST_STREAM_FRAME_RECEIVED,
        base::Bind(&NetLogQuicRstStreamFrameCallback, &frame));
}

void QuicConnectionLogger::OnConnectionCloseFrame(
    const QuicConnectionCloseFrame& frame)
{
    net_log_.AddEvent(
        NetLog::TYPE_QUIC_SESSION_CONNECTION_CLOSE_FRAME_RECEIVED,
        base::Bind(&NetLogQuicConnectionCloseFrameCallback, &frame));
}

void QuicConnectionLogger::OnWindowUpdateFrame(
    const QuicWindowUpdateFrame& frame)
{
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_WINDOW_UPDATE_FRAME_RECEIVED,
        base::Bind(&NetLogQuicWindowUpdateFrameCallback, &frame));
}

void QuicConnectionLogger::OnBlockedFrame(const QuicBlockedFrame& frame)
{
    ++num_blocked_frames_received_;
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_BLOCKED_FRAME_RECEIVED,
        base::Bind(&NetLogQuicBlockedFrameCallback, &frame));
}

void QuicConnectionLogger::OnGoAwayFrame(const QuicGoAwayFrame& frame)
{
    UMA_HISTOGRAM_BOOLEAN("Net.QuicSession.GoAwayReceivedForConnectionMigration",
        frame.error_code == QUIC_ERROR_MIGRATING_PORT);

    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_GOAWAY_FRAME_RECEIVED,
        base::Bind(&NetLogQuicGoAwayFrameCallback, &frame));
}

void QuicConnectionLogger::OnPingFrame(const QuicPingFrame& frame)
{
    // PingFrame has no contents to log, so just record that it was received.
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_PING_FRAME_RECEIVED);
}

void QuicConnectionLogger::OnPublicResetPacket(
    const QuicPublicResetPacket& packet)
{
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_PUBLIC_RESET_PACKET_RECEIVED);
    UpdatePublicResetAddressMismatchHistogram(local_address_from_shlo_,
        packet.client_address);
}

void QuicConnectionLogger::OnVersionNegotiationPacket(
    const QuicVersionNegotiationPacket& packet)
{
    net_log_.AddEvent(
        NetLog::TYPE_QUIC_SESSION_VERSION_NEGOTIATION_PACKET_RECEIVED,
        base::Bind(&NetLogQuicVersionNegotiationPacketCallback, &packet));
}

void QuicConnectionLogger::OnCryptoHandshakeMessageReceived(
    const CryptoHandshakeMessage& message)
{
    net_log_.AddEvent(
        NetLog::TYPE_QUIC_SESSION_CRYPTO_HANDSHAKE_MESSAGE_RECEIVED,
        base::Bind(&NetLogQuicCryptoHandshakeMessageCallback, &message));

    if (message.tag() == kSHLO) {
        StringPiece address;
        QuicSocketAddressCoder decoder;
        if (message.GetStringPiece(kCADR, &address) && decoder.Decode(address.data(), address.size())) {
            local_address_from_shlo_ = IPEndPoint(decoder.ip(), decoder.port());
            UMA_HISTOGRAM_ENUMERATION(
                "Net.QuicSession.ConnectionTypeFromPeer",
                GetRealAddressFamily(local_address_from_shlo_.address()),
                ADDRESS_FAMILY_LAST);
        }
    }
}

void QuicConnectionLogger::OnCryptoHandshakeMessageSent(
    const CryptoHandshakeMessage& message)
{
    net_log_.AddEvent(
        NetLog::TYPE_QUIC_SESSION_CRYPTO_HANDSHAKE_MESSAGE_SENT,
        base::Bind(&NetLogQuicCryptoHandshakeMessageCallback, &message));
}

void QuicConnectionLogger::OnConnectionClosed(QuicErrorCode error,
    const string& error_details,
    ConnectionCloseSource source)
{
    net_log_.AddEvent(
        NetLog::TYPE_QUIC_SESSION_CLOSED,
        base::Bind(&NetLogQuicOnConnectionClosedCallback, error, source));
}

void QuicConnectionLogger::OnSuccessfulVersionNegotiation(
    const QuicVersion& version)
{
    string quic_version = QuicVersionToString(version);
    net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_VERSION_NEGOTIATED,
        NetLog::StringCallback("version", &quic_version));
}

void QuicConnectionLogger::UpdateReceivedFrameCounts(
    QuicStreamId stream_id,
    int num_frames_received,
    int num_duplicate_frames_received)
{
    if (stream_id != kCryptoStreamId) {
        num_frames_received_ += num_frames_received;
        num_duplicate_frames_received_ += num_duplicate_frames_received;
    }
}

void QuicConnectionLogger::OnCertificateVerified(
    const CertVerifyResult& result)
{
    if (result.cert_status == CERT_STATUS_INVALID) {
        net_log_.AddEvent(NetLog::TYPE_QUIC_SESSION_CERTIFICATE_VERIFY_FAILED);
        return;
    }
    net_log_.AddEvent(
        NetLog::TYPE_QUIC_SESSION_CERTIFICATE_VERIFIED,
        base::Bind(&NetLogQuicCertificateVerifiedCallback, result.verified_cert));
}

base::HistogramBase* QuicConnectionLogger::GetPacketNumberHistogram(
    const char* statistic_name) const
{
    string prefix("Net.QuicSession.PacketReceived_");
    return base::LinearHistogram::FactoryGet(
        prefix + statistic_name + connection_description_, 1,
        received_packets_.size(), received_packets_.size() + 1,
        base::HistogramBase::kUmaTargetedHistogramFlag);
}

base::HistogramBase* QuicConnectionLogger::Get6PacketHistogram(
    const char* which_6) const
{
    // This histogram takes a binary encoding of the 6 consecutive packets
    // received.  As a result, there are 64 possible sample-patterns.
    string prefix("Net.QuicSession.6PacketsPatternsReceived_");
    return base::LinearHistogram::FactoryGet(
        prefix + which_6 + connection_description_, 1, 64, 65,
        base::HistogramBase::kUmaTargetedHistogramFlag);
}

base::HistogramBase* QuicConnectionLogger::Get21CumulativeHistogram(
    const char* which_21) const
{
    // This histogram contains, for each sequence of 21 packets, the results from
    // 21 distinct questions about that sequence.  Conceptually the histogtram is
    // broken into 21 distinct ranges, and one sample is added into each of those
    // ranges whenever we process a set of 21 packets.
    // There is a little rendundancy, as each "range" must have the same number
    // of samples, all told, but the histogram is a tad easier to read this way.
    // The questions are:
    // Was the first packet present (bucket 0==>no; bucket 1==>yes)
    // Of the first two packets, how many were present? (bucket 2==> none;
    //   bucket 3==> 1 of 2; bucket 4==> 2 of 2)
    // Of the  first three packets, how many were present? (bucket 5==>none;
    //   bucket 6==> 1 of 3; bucket 7==> 2 of 3; bucket 8==> 3 of 3).
    // etc.
    string prefix("Net.QuicSession.21CumulativePacketsReceived_");
    return base::LinearHistogram::FactoryGet(
        prefix + which_21 + connection_description_, 1,
        kBoundingSampleInCumulativeHistogram,
        kBoundingSampleInCumulativeHistogram + 1,
        base::HistogramBase::kUmaTargetedHistogramFlag);
}

// static
void QuicConnectionLogger::AddTo21CumulativeHistogram(
    base::HistogramBase* histogram,
    int bit_mask_of_packets,
    int valid_bits_in_mask)
{
    DCHECK_LE(valid_bits_in_mask, 21);
    DCHECK_LT(bit_mask_of_packets, 1 << 21);
    const int blank_bits_in_mask = 21 - valid_bits_in_mask;
    DCHECK_EQ(bit_mask_of_packets & ((1 << blank_bits_in_mask) - 1), 0);
    bit_mask_of_packets >>= blank_bits_in_mask;
    int bits_so_far = 0;
    int range_start = 0;
    for (int i = 1; i <= valid_bits_in_mask; ++i) {
        bits_so_far += bit_mask_of_packets & 1;
        bit_mask_of_packets >>= 1;
        DCHECK_LT(range_start + bits_so_far, kBoundingSampleInCumulativeHistogram);
        histogram->Add(range_start + bits_so_far);
        range_start += i + 1;
    }
}

float QuicConnectionLogger::ReceivedPacketLossRate() const
{
    if (largest_received_packet_number_ <= num_packets_received_)
        return 0.0f;
    float num_received = largest_received_packet_number_ - num_packets_received_;
    return num_received / largest_received_packet_number_;
}

void QuicConnectionLogger::OnRttChanged(QuicTime::Delta rtt) const
{
    // Notify socket performance watcher of the updated RTT value.
    if (!socket_performance_watcher_)
        return;

    int64_t microseconds = rtt.ToMicroseconds();
    if (microseconds != 0) {
        socket_performance_watcher_->OnUpdatedRTTAvailable(
            base::TimeDelta::FromMicroseconds(rtt.ToMicroseconds()));
    }
}

void QuicConnectionLogger::RecordAggregatePacketLossRate() const
{
    // For short connections under 22 packets in length, we'll rely on the
    // Net.QuicSession.21CumulativePacketsReceived_* histogram to indicate packet
    // loss rates.  This way we avoid tremendously anomalous contributions to our
    // histogram.  (e.g., if we only got 5 packets, but lost 1, we'd otherwise
    // record a 20% loss in this histogram!). We may still get some strange data
    // (1 loss in 22 is still high :-/).
    if (largest_received_packet_number_ <= 21)
        return;

    string prefix("Net.QuicSession.PacketLossRate_");
    base::HistogramBase* histogram = base::Histogram::FactoryGet(
        prefix + connection_description_, 1, 1000, 75,
        base::HistogramBase::kUmaTargetedHistogramFlag);
    histogram->Add(static_cast<base::HistogramBase::Sample>(
        ReceivedPacketLossRate() * 1000));
}

void QuicConnectionLogger::RecordLossHistograms() const
{
    if (largest_received_packet_number_ == 0)
        return; // Connection was never used.
    RecordAggregatePacketLossRate();

    base::HistogramBase* is_not_ack_histogram = GetPacketNumberHistogram("IsNotAck_");
    base::HistogramBase* is_an_ack_histogram = GetPacketNumberHistogram("IsAnAck_");
    base::HistogramBase* packet_arrived_histogram = GetPacketNumberHistogram("Ack_");
    base::HistogramBase* packet_missing_histogram = GetPacketNumberHistogram("Nack_");
    base::HistogramBase* ongoing_cumulative_packet_histogram = Get21CumulativeHistogram("Some21s_");
    base::HistogramBase* first_cumulative_packet_histogram = Get21CumulativeHistogram("First21_");
    base::HistogramBase* six_packet_histogram = Get6PacketHistogram("Some6s_");

    DCHECK_EQ(received_packets_.size(), received_acks_.size());
    const QuicPacketNumber last_index = std::min<QuicPacketNumber>(
        received_packets_.size() - 1, largest_received_packet_number_);
    const QuicPacketNumber index_of_first_21_contribution = std::min<QuicPacketNumber>(21, last_index);
    // Bit pattern of consecutively received packets that is maintained as we scan
    // through the received_packets_ vector. Less significant bits correspond to
    // less recent packets, and only the low order 21 bits are ever defined.
    // Bit is 1 iff corresponding packet was received.
    int packet_pattern_21 = 0;
    // Zero is an invalid packet sequence number.
    DCHECK(!received_packets_[0]);
    for (size_t i = 1; i <= last_index; ++i) {
        if (received_acks_[i])
            is_an_ack_histogram->Add(i);
        else
            is_not_ack_histogram->Add(i);

        packet_pattern_21 >>= 1;
        if (received_packets_[i]) {
            packet_arrived_histogram->Add(i);
            packet_pattern_21 |= (1 << 20); // Turn on the 21st bit.
        } else {
            packet_missing_histogram->Add(i);
        }

        if (i == index_of_first_21_contribution) {
            AddTo21CumulativeHistogram(first_cumulative_packet_histogram,
                packet_pattern_21, i);
        }
        // We'll just record for non-overlapping ranges, to reduce histogramming
        // cost for now.  Each call does 21 separate histogram additions.
        if (i > 21 || i % 21 == 0) {
            AddTo21CumulativeHistogram(ongoing_cumulative_packet_histogram,
                packet_pattern_21, 21);
        }

        if (i < 6)
            continue; // Not enough packets to do any pattern recording.
        int recent_6_mask = packet_pattern_21 >> 15;
        DCHECK_LT(recent_6_mask, 64);
        if (i == 6) {
            Get6PacketHistogram("First6_")->Add(recent_6_mask);
            continue;
        }
        // Record some overlapping patterns, to get a better picture, since this is
        // not very expensive.
        if (i % 3 == 0)
            six_packet_histogram->Add(recent_6_mask);
    }
}

} // namespace net
